Technical Note TN2124
Mac OS X Debugging Magic

This technote describes a number of 'secret' debugging facilities in Mac OS X, including environment variables, preferences, routines callable from GDB, special files, and so on. If you're developing for Mac OS X, you should look through this list to see if you're missing out on something that will make your life easier.





Introduction

Mac OS X includes a number of debugging facilities added by enginering teams to help develop and debug specific subsystems. Many of these facilities remain in the released system and you can use them to debug your code. This technote describes some of the more broadly useful ones.

In cases where a debugging facility is documented in another place, there's a short overview of the facility and a link to the existing documentation.

This is not an exhaustive list: not all debugging facilities are, or will be, documented.

WARNING: The debugging facilities described in this technote are unsupported. We reserve the right to change or eliminate each facility as dictated by the evolution of Mac OS X; this has happened in the past, and we fully expect it to happen again in the future. These facilities are for debugging only: you must not ship a product that relies on the existence or functionality of the facilities describe in this technote.

IMPORTANT: This technote is based on Mac OS X 10.3.5 (with Xcode 1.5 installed) and it is accurate for such a system. Many of the details covered in this technote vary from release to release; you may encounter minor variations on older or newer systems.

This technote covers advanced debugging techniques. If you're just getting started with Mac OS X development, you should consult the following material.

  • GDB is the fundamental debugger on Mac OS X. For a full description of GDB, see Debugging with GDB.

  • Xcode is Apple's integrated development environment (IDE). It includes a sophisticated graphical debugger, implemented as a wrapper around GDB. For more information about Xcode, see the Xcode section of the Apple developer Reference Library.

Back to Top 

Basics

The later sections of this technote describe the debug facilities of Mac OS X in detail. Many these facilities use similar techniques to enable and disable the facility, and to see its output. This section describes these common techniques.

Enabling Debugging Facilities

Some debugging facilities are enabled by default. However, most facilities must be enabled using one of the following.

Environment Variables

In many cases you can enable a debugging facility by setting a particular environment variable. The easiest way to do this is to launch your application from Terminal, and specify the environment variable on the command line. Listing 1 shows how to set an environment variable in the sh shell; Listing 2 shows the equivalent in csh.

Listing 1: Setting an environment variable in an sh-compatible shell

$ MallocStackLogging=1 /Applications/TextEdit.app/Contents/MacOS/TextEdit
malloc[1002]: recording stacks using standard recorder
[...]

Listing 2: Setting an environment variable in a csh-compatible shell

% setenv MallocStackLogging 1
% /Applications/TextEdit.app/Contents/MacOS/TextEdit
malloc[1004]: recording stacks using standard recorder
[...]

Note: The default shell in Mac OS X 10.3 and later is bash, an sh-compatible shell. The default shell in Mac OS X 10.2.x and earlier was tcsh, a csh-compatible shell. The remainder of this technote assumes that you're using bash.

IMPORTANT: If you're using a csh-compatible shell, don't forget to reset (using the unsetenv command) any debugging environment variables once you've finished debugging. Otherwise these settings may adversely affect your future commands.

Alternatively, open two Terminal windows and use the first exclusively for debugging and the second for all other commands.

In addition, you can set environment variables in GDB, as shown in Listing 3.

Listing 3: Setting an environment variable in GDB

$ gdb /Applications/TextEdit.app
GNU gdb 5.3-20030128 (Apple version gdb-330.1) [...]
(gdb) set env MallocStackLogging 1
(gdb) r
Starting program: /Applications/TextEdit.app/Contents/MacOS/TextEdit
malloc[1062]: recording stacks using standard recorder
[...]

If you're using Xcode to build and debug your application, you can set environment variables using the executable inspector. Figure 1 shows an example of this.

Figure 1: Setting environment variables in Xcode

Figure 1, Setting environment variables in Xcode

Finally, Mac OS X provides a mechanism for setting environment variables for all processes launched by a specific user. See Technical Q&A QA1067, 'Setting environment variables for user processes' for details.

Back to Top 

Preferences

You can enable other debugging facilities by setting a preference using the defaults command line tool. Listing 4 shows how to do this. This listing sets the NSTraceEvents preference for the TextEdit application (whose bundle identifier is com.apple.TextEdit) to YES.

Listing 4: Setting a preference using defaults

$ defaults write com.apple.TextEdit NSTraceEvents YES
$ /Applications/TextEdit.app/Contents/MacOS/TextEdit
2004-08-30 16:47:55.851 TextEdit[1135] timeout = 62998416724.149353 secoÖ
2004-08-30 16:47:55.894 TextEdit[1135] got apple event of class 61657674Ö
[...]

Once you're finished debugging, you should delete the preference, also using defaults, as shown in Listing 5.

Listing 5: Deleting a preference using defaults

$ defaults delete com.apple.TextEdit NSTraceEvents

For more information about defaults, consult its man page.

Cocoa applications also let you set temporary preferences on the command line. For example, Listing 6 shows how to achieve equivalent results to Listing 4 without modifying any permanent preferences.

Listing 6: Temporarily setting a preference

$ /Applications/TextEdit.app/Contents/MacOS/TextEdit -NSTraceEvents YES
2004-10-25 17:28:41.143 TextEdit[5774] timeout = 62993575878.857864 secoÖ
2004-10-25 17:28:41.179 TextEdit[5774] got apple event of class 61657674Ö
[...]

Back to Top 

Files

Certain debugging facilities are enabled by the existence of specific files within the file system. Listing 7 shows an example of this: creating the /var/tmp/do_xnc_log causes CFNotificationCenter to record information about all notifications to files within the /var/tmp/xnc_logs/ directory.

Listing 7: Create a specific file to enable debugging

$ touch /var/tmp/do_xnc_log

[... now log out and log back in ...]

$ cat /var/tmp/xnc_logs/loginwindow
-------------------------------------------------
[0xa000a1ec] created notification center 0x40ccb0 0
[0xa000a1ec] register 0x40ccb0 _NSAppleEventManagerDidFailToDispatchNotiÖ
[...]

Back to Top 

Callable Routines

Many system frameworks include routines that print debugging information to stderr. These routines are specifically designed to be callable from within GDB. Listing 8 shows an example of this, in this case calling the GDBComponentList routine to print a list of components and their instances (the equivalent of the thing MacsBug command on traditional Mac OS).

Listing 8: Calling a debugging routine from GDB

(gdb) call (void) GDBComponentList()
Cnt tRef# (address) Type/SubT/Manu Flags    EntryPnt File Parnt ThingName
  0 10008  0180d540 adec/.mp3/appl 10000000 00000000   -3 00000 (Not loadeÖ
[Ö]
  2 1012c  005c3be0 clok/micr/appl 10000003 8b1586a8    1 00000 (Not loadeÖ
        Inst:0x850003; Err=0; Storage:0x1fe6f0
        Inst:0x890004; Err=0; Storage:0x1fe6f8
  0 10065  0180fd08 clok/soun/appl 00000005 00000000   -3 00000 (Not loadeÖ
[Ö]
There are 9 component manager files:
        0: refs 2, path [/System/Library/Components/VCH263Codec.component]Ö
        1: refs 94, path [/System/Library/QuickTime/QuickTimeComponents.coÖ
        2: refs 5, path [/System/Library/Components/IOQTComponents.componeÖ
        3: refs 2, path [/System/Library/QuickTime/QuickTimeVR.component],Ö
        4: refs 7, path [/System/Library/QuickTime/QuickTimeFirewireDV.comÖ
        5: refs 1, path [/System/Library/QuickTime/QuickTimeMPEG4.componenÖ
        6: refs 1, path [/System/Library/Components/PDFImporter.component]Ö
        7: refs 1, path [/System/Library/QuickTime/ApplePixletVideo.componÖ
        8: refs 1, path [/System/Library/QuickTime/QuickTimeStreaming.compÖ

If you don't see the output from the routine, you may need to look at the console log, as described in the next section.

Back to Top 

Seeing Debug Output

Programs that generate debug output generally do so using one of three different mechanisms.

  • printing to stderr

  • system log

  • kernel trace facility

Printing to stderr is the most commonly used output mechanism. Given this topic's importance, I cover it in depth in the next section.

The other two mechanism are much simpler. You can view the system log using the Console application (in /Applications/Utilities). You can learn more about it in the syslog man pages (syslog, syslog.conf, and syslogd).

The kernel trace facility is a highly specialized low-latency, high-availability logging mechanism. In most cases a program that logs to the kernel trace facility also includes a way to view the logs (for example, you can using kdump to print a trace file generated using ktrace).

Console Output

Many programs, and indeed many system frameworks, print debugging messages to stderr. The destination for this output is ultimately controlled by the program: it can redirect stderr to whatever destination it choose. However, in most cases a program does not redirect stderr, so the output goes to the default destination inherited by the program from its launch environment. This is typically one of the following.

  • If you launch a GUI application in the normal way (for example, by double clicking the application in the Finder), the system connects its stderr to the console device (/dev/console). You can view its output using the Console application (in /Applications/Utilities). Additionally, the output is recorded to the file /Library/Logs/Console/<username>/console.log.

  • If you run a program (be it GUI or non-GUI) from within Terminal, its stderr is connected to your Terminal window; anything the program prints will appear in this window. This also applies to programs run from GDB within a Terminal window.

  • If you run a program from within Xcode, you can see its stderr output in Xcode's Run Log or Console Log windows (choose the corresponding command from the Debug menu to see the window).

Attaching to a running program (using the attach command in GDB) does not automatically connect the program's stderr to your GDB window. You can do this from within GDB using the trick described in the "Seeing stdout and stderr After Attaching" section of Technical Note TN2030, 'GDB for MacsBug Veterans'.

Back to Top 

CrashReporter

CrashReporter is an invaluable debugging facility that logs information about all programs that crash. It is described in detail in Technical Note TN2123, 'CrashReporter'. CrashReporter is enabled all the time; all you have to do is look at its output.

Back to Top 

BSD

The BSD subsystem implements process, memory, file, and network infrastructure, and thus is critical to all applications on Mac OS X. BSD implements a number of neat debugging facilities that you can take advantage of.

Core Dumps

Core dumps have an undeserved reputation as a primitive debugging facility. In reality they can be very helpful when debugging difficult problems, especially when you can't reproduce the problem locally.

You can enable core dumps on a system-wide basis by changing the line "COREDUMPS=-NO-" in /etc/hostconfig to "COREDUMPS=-YES-" and then restarting. Alternatively, if you run your program from Terminal, you can simply raise the core dump size limit in the shell beforehand. Listing 9 shows an example of this.

Listing 9: Unlimited core dump size

$ ulimit -c unlimited
$ /Applications/TextEdit.app/Contents/MacOS/TextEdit
[...]

To test the core dump facility, send your program a SIGABRT using the kill command, as demonstrated by Listing 10.

Listing 10: Testing core dumps by sending a SIGABRT

$ ps | grep TextEdit
  374  p1  S+     0:00.58 /Applications/TextEdit.app/Contents/MacOS/TextEdit
  379 std  S+     0:00.01 grep TextEdit
$ kill -ABRT 374

Your application will then quit with a "Abort trap (core dumped)" message. You can find the core dump in /cores. You can work out which core dump is which using the otool command. Finally, you can debug the core dump using GDB with the -c argument. Listing 11 shows an example of this process.

Listing 11: Using core dumps

Abort trap (core dumped)
$ ls -lh /cores
total 296856
-r--------  1 quinn  admin       144M 29 Oct 10:23 core.374
$ otool -c /cores/core.374
/cores/core.374:
Argument strings on the stack at: 0xc0000000
        /Applications/TextEdit.app/Contents/MacOS/TextEdit

        /Applications/TextEdit.app/Contents/MacOS/TextEdit
        TERM_PROGRAM=Apple_Terminal
        TERM=xterm-color
        SHELL=/bin/bash
        TERM_PROGRAM_VERSION=100
        USER=quinn
        __CF_USER_TEXT_ENCODING=0x1F5:0:15
        PATH=/bin:/sbin:/usr/bin:/usr/sbin
        PWD=/Users/quinn
        SHLVL=1
        HOME=/Users/quinn
        LOGNAME=quinn
        SECURITYSESSIONID=20f550
        _=/Applications/TextEdit.app/Contents/MacOS/TextEdit
$ gdb -c /cores/core.374
GNU gdb 5.3-20030128 (Apple version gdb-292) (Sat Sep 20 03:22:27 GMT 2003)
Copyright 2003 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "powerpc-apple-darwin".
Core was generated by `/Applications/TextEdit.app/Contents/MacOS/TextEdit'.
#0  0x900075c8 in ?? ()
(gdb) bt
#0  0x900075c8 in ?? ()
#1  0x90007118 in ?? ()
#2  0x901960bc in ?? ()
#3  0x927d5ecc in ?? ()
#4  0x927dc640 in ?? ()
#5  0x927fe6d0 in ?? ()
#6  0x92dd2a80 in ?? ()
#7  0x92de93fc in ?? ()
#8  0x92dfd730 in ?? ()
#9  0x92eb9a1c in ?? ()
#10 0x00007d98 in ?? ()
#11 0x00007c0c in ?? ()

As you can see from Listing 11, core dumps do not contain debugger symbols. If you have a symbol file handy, you can tell GDB to consult it using the add-symbol-file command. Listing 12 shows how to do this for the system frameworks used by this TextEdit backtrace.

Listing 12: Adding symbols

(gdb) add-symbol-file /System/Library/Frameworks/AppKit.framework/AppKit
[Ö]
(gdb) add-symbol-file /System/Library/Frameworks/CoreFoundation.framework\
/CoreFoundation
[Ö]
(gdb) add-symbol-file /System/Library/Frameworks/System.framework/System
[Ö]
#12 0x00007c0c in ?? ()
(gdb) add-symbol-file /System/Library/Frameworks/Carbon.framework/\
Frameworks/HIToolbox.framework/HIToolbox
[Ö]
(gdb) bt
#0  0x900075c8 in mach_msg_trap ()
#1  0x90007118 in mach_msg ()
#2  0x90191930 in __CFRunLoopRun ()
#3  0x901960bc in CFRunLoopRunSpecific ()
#4  0x927d5ecc in RunCurrentEventLoopInMode ()
#5  0x927dc640 in ReceiveNextEventCommon ()
#6  0x927fe6d0 in BlockUntilNextEventMatchingListInMode ()
#7  0x92dd2a80 in _DPSNextEvent ()
#8  0x92de93fc in -[NSApplication nextEventMatchingMask:untilDate:inMode:Ö
#9  0x92dfd730 in -[NSApplication run] ()
#10 0x92eb9a1c in NSApplicationMain ()
#11 0x00007d98 in ?? ()
#12 0x00007c0c in ?? ()

IMPORTANT: Core dumps are large. In the example Listing 11, TextEdit's core dump is 144 MB. If you have core dumps enabled as a matter of course, make sure that you regularly clean out /cores to avoid filling up your startup disk.

Back to Top 

Memory Allocator

The default memory allocator includes a number of debugging facilities that you can enable via environment variables. These are fully documented in the manual page. Table 1 lists some of the more useful ones.

Table 1: Some useful memory allocator environment variables

VariableSummary
MallocScribbleFill deallocated memory with 0x55
MallocGuardEdgesAdd guard pages before and after large allocations
MallocStackLoggingRecord stack logs for each memory block to assist memory debugging tools
MallocStackLoggingNoCompactRecord stack logs for all operations to assist memory debugging tools

IMPORTANT: These environment variables do not require a special memory library (like MallocDebug or the Guarded Memory Allocator). In fact, they are supported by the default, non-debug memory allocator, and are, therefore, always available.

The default memory allocator also logs messages if it detects certain common programming problems. For example, if you free a block of memory twice, or free memory that you never allocated, free may print the message shown in Listing 13. The number inside square brackets is the process ID.

Listing 13: A common message printed by free

*** malloc[4691]: Deallocation of a pointer not malloced: 0x1000;  \
This could be a double free(), or free() called with the middle of \
an allocated block; Try setting environment variable MallocHelp to \
see tools to help debug

You can debug this sort of problem by running your program within GDB and putting a breakpoint on malloc_printf, which is the routine used to print these messages. Once you hit the breakpoint, you can use GDB's backtrace command to determine the immediate caller.

Back to Top 

MallocDebug and ObjectAlloc

Mac OS X includes two GUI applications for memory allocation debugging, MallocDebug and ObjectAlloc. For more information about these tools, see the Memory Performance document.

Back to Top 

Guarded Memory Allocator

Mac OS X includes a guarded memory allocator, libgmalloc, that you can use during debugging to catch common memory problems, such as buffer overruns and use-after-free. Listing 14 shows an example of how to enable it.

Listing 14: Enabling libgmalloc

$ gdb /Applications/TextEdit.app
GNU gdb 5.3-20030128 (Apple version gdb-330.1) [Ö]
(gdb) set env DYLD_INSERT_LIBRARIES /usr/lib/libgmalloc.dylib
(gdb) set env DYLD_FORCE_FLAT_NAMESPACE 1
(gdb) set env MALLOC_FILL_SPACE 1
(gdb) r
Starting program: /Applications/TextEdit.app/Contents/MacOS/TextEdit
Allocations will be placed on word (4 byte) boundaries.
 - Small buffer overruns may not be noticed.
 - Applications using AltiVec instructions may fail.
GuardMalloc-8
Reading symbols for shared libraries [Ö]

You can learn more about libgmalloc from its man page.

Back to Top 

Command Line Tools

Mac OS X includes a number of cool command line tools for debugging. I've listed my favorite tools in Table 2.

Table 2: Command line tool highlights

ToolDocumentationSummary
gdbmanual pageCommand line debugger
fs_usagemanual pageFile system trace tool
sc_usagemanual pageSystem call trace tool
latencymanual pageScheduling latency debugging tool
ktrace, kdumpmanual pageKernel tracing
heapmanual pageHeap dump
vmmapmanual pageAddress space dump
malloc_historymanual pageMemory allocation history
leaksmanual pageLeak detection
tcpdumpmanual page, Technical Q&A QA1176, 'Getting a Packet Trace'Network packet trace
netstatmanual pageNetwork statistics; netstat -an shows all network connections
lsofmanual pageList open files
PPCExplainPPC mnemonic explained

Back to Top 

Dynamic Linker (dyld)

The Mac OS X dynamic linker (dyld) supports a number of debugging facilities that you can enable via environment variables. These are fully documented in the manual page. Table 3 lists some of the more useful variables.

Table 3: Dynamic linker environment variables

VariableSummary
DYLD_IMAGE_SUFFIXSearch for libraries with this suffix first
DYLD_PRINT_LIBRARIESPrint library names as they're loaded
DYLD_PRINT_LIBRARIES_POST_LAUNCHAs above, but only after main has run
DYLD_PREBIND_DEBUGPrint prebinding diagnostics

Of these, DYLD_IMAGE_SUFFIX is the most useful because you can use it to enable the system's debug libraries, as described in the next section.

Debug Libraries

Many Mac OS X frameworks include both a production and a debug variant. The debug variant has the suffix "_debug". For example, the Core Foundation framework's production variant is /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation while its debug variant is /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation_debug. You can force dyld to load the debug variant of a library (if such a variant exists) by setting the DYLD_IMAGE_SUFFIX environment variable to "_debug". Listing 15 shows an example of how to do this from within Terminal.

Listing 15: Using _debug libraries

$ DYLD_IMAGE_SUFFIX=_debug /Applications/TextEdit.app/Contents/MacOS/TextEdit
2004-08-30 18:32:06.051 TextEdit[1393] CFLog (0): Assertions enabled
[...]

If Terminal doesn't float your boat, you can do the same using the executable inspector in Xcode. In Figure 2, you can see that the "Use Ö suffix when loading frameworks" popup has been set to "debug".

Figure 2: Enabling debug libraries in Xcode

Figure 2, Enabling debug libraries in Xcode

The exact behavior of the debug library varies from framework to framework. Most debug libraries include:

  • full debug symbols ó This is particularly useful if the source for the framework is included in Darwin.

  • extra assertions ó These can help pinpoint programming errors on your part.

  • extra debugging facilities ó A number of the debugging facilities described later in this document are only available in the debug library.

I strongly recommend that you use the debug libraries as part of your day-to-day debugging process.

Note: Unless otherwise stated, the debugging facilities in this technote do not require you to use the debug libraries.

Back to Top 

Enabling Just One Debug Library

In some circumstances you might want to enable just one debug library. For example, let's say you're debugging an Apple event problem, so you want to enabled the "_debug" variant of the AE framework. However, when you set DLYD_IMAGE_SUFFIX to "_debug", you discover that using all the debug libraries causes a problem elsewhere in your application. At this time you just want to focus on debugging the Apple event problem. What do you do?

Fortunately there's a simple, albeit somewhat unsubtle, answer: just copy the debug variant over the non-debug variant. Listing 16 shows an example of this.

Listing 16: Activating just the AE debug library

$ cd /System/Library/Frameworks/ApplicationServices.framework/\
Frameworks/AE.framework/Versions/A/
$ sudo cp -n AE AE_original
Password: ********
$ sudo cp AE_debug AE

Once you've done this, you should restart to activate your change.

IMPORTANT: This technique is useful for debugging but it has a number of negative effects. For example, the debug library is prebound at a different address from the non-debug library, so prebound programs won't be able to launch prebound, and thus will launch slower. Therefore, I recommend that you do this only on a dedicated test computer or, if that's not practical, on your main computer while booted from a test system. Moreover, you should revert to the original library as soon as you've finished debugging.

To revert back to the non-debug library, you can just copy the original library back, as shown in Listing 17.

Listing 17: Deactivating the AE debug library

$ sudo cp AE_original AE
Password: ********

Note: The reason why I recommend copying the libraries rather than renaming them is that it make it harder to accidentally overwrite your last copy of a library.

Back to Top 

Escaping the Window Server

Under some circumstances it can be helpful to operate without the window server. For example, if you need to modify the parameters to loginwindow specified in /etc/ttys, it's nice to be able to do it while loginwindow is not running. Mac OS X provides a convenient way to do this.

  • In the Accounts panel of System Preferences, click on Login Options.

  • Change the "Display Login Window as" setting to "Name and password".

  • Log out.

  • At the login window, enter ">console" as your user name; loginwindow will quit and you'll be faced with a glass TTY interface displaying the "Login" prompt.

  • Log in using your standard user name and password.

When you're done working at this level, just exit from your shell (using the exit command) and you will return to the standard login window.

IMPORTANT: This environment is not single user mode. Most system daemons are still running; only the GUI components of the system are shut down.

Back to Top 

Core Services

Core Services includes a number of routines (for example, Debugger, DebugStr, and SysBreak) that enter the debugger with a message. If you set the USERBREAK environment variable to 1, these routines will send a SIGINT signal to the current process, which causes you to break into GDB. Xcode has GUI to enabled this facility (the "Break on Debugger() and DebugStr()" checkbox in the Debugging panel of the executable inspector, as shown in Figure 3).

Figure 3: Setting USERBREAK in Xcode

Figure 3, Setting USERBREAK in Xcode

Code Fragment Manager (CFM)

The CFM compatibility environment on Mac OS X supports two helpful environment variables, CFMDebugBasic and CFMDebugFull, which you can set to 1 to get limited and verbose debug logging, respectively. This facility is particularly useful for tracking down CFM closure problems, and problems where fragment initialization routines fail.

Back to Top 

Core Foundation

All variants of the Core Foundation (CF) framework support the CFShow routine, which prints a description of any CF object to stderr. You can make this call from your own code, however, it's particularly useful when called from GDB. Listing 18 shows an example of this.

Listing 18: Calling CFShow from GDB

$ gdb /Applications/TextEdit.app
GNU gdb 5.3-20030128 (Apple version gdb-330.1) [Ö]
(gdb) fb *CFRunLoopAddSource
No symbol table is loaded.  Use the "file" command.
Breakpoint 1 at 0x0
(gdb) r
[Ö]
Breakpoint 1, 0x901b5764 in CFRunLoopAddSource ()
(gdb) call (void) CFShow($r3)
<CFRunLoop 0x116290 [0xa01900e0]>{
    locked = false,
    wait port = 0xf03,
    stopped = false,
    current mode = (none),
    common modes = <CFSet 0x1162c0 [0xa01900e0]>{
        count = 1,
        capacity = 4,
        values = (
            1 : <CFString 0xa0195b38 [0xa01900e0]>{
                contents = "kCFRunLoopDefaultMode"
            }
        )
    },
    common mode items = (null),
    modes = <CFSet 0x116310 [0xa01900e0]>{
        count = 1,
        capacity = 17,
        values = (
            20 : <CFRunLoopMode 0x1163a0 [0xa01900e0]>{
                name = kCFRunLoopDefaultMode,
                locked = false,
                port set = 0x1003,
                sources = (null),
                observers == (null),
                timers = (null)
            },
        )
    }
}

IMPORTANT: If you don't see any output from CFShow, it was probably sent to the console. See Seeing Debug Output for information about how to view this output.

Note: In Listing 18 I've reformatted the output from CFShow to make it easier to read.

There are a number of other CF routines that you might find useful to call from GDB, including CFGetRetainCount, CFBundleGetMainBundle, and CFRunLoopGetCurrent.

The Core Foundation framework also has a debug variant that offers extensive debugging assistance. For example, the non-debug variant of Core Foundation does not check the validity of parameters that you pass to its routines, whereas the debug variant includes full parameter checking. This can help you track down numerous Core Foundation-related bugs in your code.

The Core Foundation debug library supports an environment variable called CFZombieLevel. It interprets this variable as an integer containing a set of flag bits. Table 4 describes the bits that are currently defined. These can help you track down various CF memory management issues.

Table 4: Bit definitions for CFZombieLevel environment variable

BitAction
0scribble deallocated CF memory
1when scribbling deallocated CF memory, don't scribble object header (CFRuntimeBase)
4never free memory used to hold CF objects
7if set, scribble deallocations using bits 8..15, otherwise use 0xFC
8..15if bit 7 is set, scribble deallocations using this value
16scribble allocated CF memory
23if set, scribble allocations using bits 24..31, otherwise use 0xCF
24..31if bit 16 is set, scribble allocations using this value

CFNotificationCenter

You can enable CFNotificationCenter logging by creating files in /var/tmp. One file, /var/tmp/do_xnc_log, controls client-side logging. If you create this file, CFNotificationCenter will log each client's activity to a file (/var/tmp/xnc_logs/<progname>). This setting takes effect when you relaunch the program.

The other file, /var/tmp/do_dnserver_log, controls server-side logging. If you create this file, the CFNotificationCenter daemon (distnoted) will log activity to /var/tmp/dnserver.log. This change takes effect when you relaunch distnoted; the safest way to do this is to restart.

Back to Top 

Component Manager

Component Manager exports a routine, GDBComponentList, that you can call from GDB to print the database of registered components and their instances. Listing 8 gives an example of its use.

In addition, if you set the ComponentDebug environment variable to 1, Component Manager will print of variety of debug messages. These may be helpful if something is going wrong with your component, in particular if it fails to load.

Back to Top 

File Manager

Core Services File Manager (commonly known as the Carbon File Manager) has a number of useful GDB-callable routines. The most useful, PrintVolumeInfo, prints the volume list. It takes one parameter that specifies whether to use the File Manager API to enumerate the volumes (1) or to walk an internal data structure (0). The former results in a nice summary while the latter yields more detailed information. Listing 19 shows an example of each.

Listing 19: PrintVolumeInfo in action

(gdb) call (void) PrintVolumeInfo(1)
1:vol=-100      "X2"
2:vol=-101      "X1"
3:vol=-102      "Guy Smiley"
4:vol=-130      "UFS Victim"
5:vol=-105      "Network"
6:returned error -35
(gdb) call (void) PrintVolumeInfo(0)
Volume Information:
        "X2"    mountpoint: "/"
                vRef=-100  volID=-100 diskID=disk0s10
        "X1"    mountpoint: "/Volumes/X1"
                vRef=-101  volID=-101 diskID=disk0s9
        "Guy Smiley"    mountpoint: "/Volumes/Guy Smiley"
                vRef=-102  volID=-102 diskID=disk0s11
        "UFS Victim"    mountpoint: "/Volumes/UFS Victim"
                vRef=-130  volID=-130 diskID=disk3s2
        "Network"       mountpoint: "/Network"
                vRef=-105  volID=-105 diskID=/Network

There are two other routines, PrintFileIDTree and PrintEnumerationCache, that print information about compatibility structures maintained by the File Manager for non-volfs volumes (see Technical Q&A QA1113, 'The "/.vol" directory and "volfs"' for information about volfs). They both take a vRefNum parameter. PrintFileIDTree prints the mapping from file IDs to file paths on the volume. PrintEnumerationCache prints the directory enumeration cache on the volume. These two routines are primarily of interest to folks developing VFS plug-ins on Mac OS X.

Finally, File Manager is nicely integrated with the fs_usage command line tool. If you enable the Core Services debug library, fs_usage will not only show primitive BSD file system calls but also the File Manager calls that prompted them. See the fs_usageman page for more details.

Back to Top 

Folder Manager

The Folder Manager supports a single environment variable, FolderDebug. If you set this to 1, the Folder Manager will print a number of extra debugging messages. This facility requires the Core Services debug library.

Back to Top 

Gestalt

Core Services exports a three routinesóDebugDumpGestalt, DebugGestalt, and DebugGestaltStróthat you can call from GDB to view the Gestalt registry. Listing 20 shows an example of their use.

Listing 20: Using the Gestalt debug routines

(gdb) call (void) DebugDumpGestalt()
DebugDumpGestalt
'a/ux': 0x2a65c6ac (proc)
'addr': 0x00000007
[Ö]
(gdb) call (void) DebugGestalt(0x766d2020)
'vm  ': 0x00000011
(gdb) call (void) DebugGestaltStr("vm  ")
'vm  ': 0x00000011

Back to Top 

Threading

The Core Services threading APIs (MP threads and Thread Manager) support an environment variable, ThreadDebug, that enables a few debug messages and a number of internal consistency checks. This facility requires the Core Services debug library.

Back to Top 

Web Services

Web Services supports two helpful environment variables, WSDebug and WSDebugVerbose, which you can set to 1 to get limited and verbose debug logging, respectively. These variables are effective in the non-debug library, but include even more logging in the debug library.

Back to Top 

Disks and Discs

Disk Arbitration

If you append a "-d" to the Command property in /etc/mach_init.d/diskarbitrationd.plist and then restart, Disk Arbitration will log detailed information about its activities to /var/log/diskarbitrationd.log.

Back to Top 

Disc Recording

If you set the DRVerboseLogging environment variable to 1, Disc Recording will log information to the console.

Back to Top 

Printing (CUPS)

Mac OS X 10.2 and later uses CUPS (Common UNIX Printing System) as its core printing architecture. CUPS has a built-in debug logging feature, controlled by the CUPS configuration file (/etc/cups/cupsd.conf). Within this file the LogLevel directive controls the level of logging, while the ErrorLog directive controls the log destination (the default is /var/log/cups/error_log). For more information about this file, see the man page.

IMPORTANT: After changing this file you must send a SIGHUP to the CUPS daemon for you changes to take effect. Listing 21 shows one way to do this.

Listing 21: Restarting the CUPS daemon

sudo /System/Library/StartupItems/PrintingServices/PrintingServices restart

If you're writing a CUPS driver or filter, you can add entries to this log by printing them to stderr. You must start each line with the logging level of the message, as illustrated by Listing 22.

Listing 22: Logging to CUPS

// Debug message

fprintf(stderr, "DEBUG: page_width = %.0f\n", page_width);

// Warning message

fprintf(stderr, "WARNING: Printer not responding\n");

// Error message

fprintf(stderr, "ERROR: Lost connection with printer\n");

Back to Top 

ApplicationServices

Apple Events

The Apple Event Manager has extensive built-in debugging support. The best way to learn about this support is use GDB to call the GDBPrintHelpDebuggingAppleEvents routine, as shown in Listing 23.

Listing 23: Apple Event Manager debugging help

(gdb) call (void) GDBPrintHelpDebuggingAppleEvents()
The AppleEvent Manager has been completely rewritten for this
version of Mac OS X.  The internal structure of an AEDesc is
now a pointer to a sparse tree.  If you're having problems
it could be because you're accessing the dataHandle of an
AEDesc directly.

Also of note is that AEGetDescData and AEGetDescDataSize only
work with value descriptors created by AECreateDesc - you cannot
get the data size of an AERecord or AEList, for example.

To print the contents of an AppleEvent from GDB, you can:
  (gdb) call (void) GDBPrintAEDesc(descPtr)

To view all currently installed AppleEvent coercion handlers:
  (gdb) call (void) GDBPrintAECoercionTables()

To view all contents install AppleEvent handlers:
  (gdb) call (void) GDBPrintAEHandlerTables()

Additionally, to log information about AppleEvent manager calls,
you can set environment variables that will produce debugging output
to the console:

  % setenv AEDebug         1            # general debug output
  % setenv AEDebugSends    1            # print sent events
  % setenv AEDebugReceives 1            # print received events and replies
  % setenv AEDebugVerbose  1            # print result information on (most) \
                                          calls (very verbose)
  % setenv AEDebugOSL      1            # print result information from OSL
  % setenv AEDebugFile     /tmp/logfile # send debug output to this file

Note: In the above text, "this version of Mac OS X" refers to Mac OS X 10.2.

Some environment variablesóspecifically AEDebug, AEDebugVerbose, AEDebugOSL, and AEDebugFileóare only supported by the debug library.

If you are using the debug library, you can also control Apple event debugging by creating three files in /var/tmp.

  • Creating the file /var/tmp/AEDebug is equivalent to setting the AEDebug, AEDebugSends, AEDebugReceives, AEDebugReceives, and AEDebugOSL environment variables.

  • Creating the file /var/tmp/AEDebug.out is equivalent to setting AEDebugFile to "/var/tmp/AEDebug.out".

  • Creating the file /var/tmp/AEDebugLogs causes Apple Event Manager to send all of its output to a file named /var/tmp/AELog-<progname>.

IMPORTANT: The last two items only affect the destination of the debugging output. In order to produce debugging output, you have to enable it using one of the environment variables listed above, or by creating /var/tmp/AEDebug.

Remote Apple Events

If you're having problems with remote Apple events, you may find it useful to enable logging on the Apple event server process. To do this, edit /etc/xinetd.d/eppc, uncomment the "server_args" line, and change the parameter value to "--debug". The end result should be a file like the one shown in Listing 24.

Listing 24: Enabling remote Apple event debugging

# EPPC is the remote AppleEvents service
#
service eppc
{
        disable             = no
        socket_type         = stream
        wait                = no
        user                = eppc
        server              = /System/Library/Frameworks/\
ApplicationServices.framework/Frameworks/AE.framework/\
Versions/A/Support/AEServer
        server_args         = --debug
        groups              = yes
        flags               = REUSE
}

You must stop and start the Remote Apple Events service for this change to take effect; you can do this in the Sharing panel of System Preferences. The logging information will appear in the system log.

IMPORTANT: Because AEServer is launched on demand by xinetd, you won't see any log entries until you actually send an Apple event to the machine.

Back to Top 

Process Manager

There are circumstances where you want to debug a process, but you don't want to launch it from within GDB. For example, if you've ssh'd into a remote computer in order to debug a GUI application, you shouldn't launch it directly from GDB because the application will be in the wrong Mach bootstrap namespace, and thus can't connect to critical services like the pasteboard server. Normally this isn't a problem: you simply ask the remote user to launch the application for you and then attach to the running application using GDB's attach command. However, what happens if you want to debug the application's startup procedure? You end up playing the 'attach race' game, where the user launches the application and you race to attach with GDB. Not good.

Process Manager offers a nice solution to this problem. If you set the INIT_Processes environment variable to 1, Process Manager will delay the application's launch for 15 seconds, giving you time to attach with GDB. It even logs a nice message (see Listing 25) to the system log letting you know what it's doing.

Listing 25: System log message generated by paused process

Sep  7 14:18:37 guy-smiley QuickTime Player: Blocking on INIT_Processes \
for 15 seconds; attach to pid 4344 if you want.

Back to Top 

QuickDraw

QuickDraw exports a number of routines that you can call from GDB to get information about QuickDraw state. The first three routinesóQDDebugPrintPortInfo, QDDebugPrintCGSInfo, and QDDebugDumpRegionóprint information to stderr. Listing 26 shows an example of their use.

Listing 26: QuickDraw printing routines

(gdb) set $window = (void *) FrontWindow()
(gdb) set $port = (void *) GetWindowPort($window)
(gdb) call (int) QDDebugPrintPortInfo($port)
Dumping port 0x435670...
    PixMap:              0x1FE72C
        Base Address:    0xB0028000 [onscreen, buffered]
        RowBytes:        0xFFFF9400
        Bounds:          (0, 0, 106, 352)  (352w x 106h)
        Depth:           0020
    Port bounds:         (0, 0, 106, 352)  (352w x 106h)
    Port shape:          0x1FE798 (0, 0, 106, 352)  (352w x 106h) Ö
    Vis rgn:             0x1FE730 (0, 0, 106, 352)  (352w x 106h) Ö
    Clip rgn:            0x1FE738 (-32000, -32000, 32000, 32000)  Ö
    Fore Color:          0000 0000 0000
    Back Color:          FFFF FFFF FFFF
[Ö]
$21 = 0
(gdb) call (int) QDDebugPrintCGSInfo($port)
CGS info for port 0x435670
    CGSWindowID:           19798
    Shape:                 0x59E734 (99, 785, 205, 1137)  (352w x Ö
    Vis Region:            0x59E72C (0, 0, 0, 0)  (0w x 0h) [rect]
    Dirty Region:          0x59E730 (0, 0, 0, 0)  (0w x 0h) [rect]
$20 = 0
(gdb) echo 0x1FE730 is "Vis rgn" from QDDebugPrintPortInfo\n
0x1FE730 is "Vis rgn" from QDDebugPrintPortInfo
(gdb) set $rgn=0x1FE730
(gdb) call (int)QDDebugDumpRegion($rgn)
Size = 116  Bounds = (0, 0, 106, 352)  (352w x 106h)  NEW FORMAT
0: 2 350
1: 1 351
2: 0 352
104: 1 351
105: 2 350
106:

$21 = 0

The remaining routines are designed to help you visualize regions on screen by flashing the region shape. Listing 27 shows how to call these routines; unfortunately you can't see the results in this document, so you'll have to try this yourself. It assumes that the $port and $rgn convenience variables are set up as per Listing 26.

Listing 27: QuickDraw flashing routines

(gdb) call (int) QDDebugFlashRegion($port, $rgn)
$23 = 0
(gdb) call (void) QDDebugFlashClipRgn($port)
(gdb) call (void) QDDebugFlashPortShape($port)
(gdb) call (void) QDDebugFlashVisRgn($port)
(gdb) call (int) QDDebugFlashCGSWindowShape($port)
$24 = 0
(gdb) call (int) QDDebugFlashCGSWindowOpaqueShape($port)
$25 = 0
(gdb) call (int) QDDebugFlashCGSVisRgn($port)
$26 = 0
(gdb) call (int) QDDebugFlashCGSDirtyRgn($port)
$27 = 0

Back to Top 

Carbon (HIToolbox)

Carbon's HIToolbox includes a wealth of facilities for your debugging convenience.

  • There is a debug variant of the HIToolbox library that prints debugging messages when it encounters errors.

  • There are numerous HIToolbox routines that you can call from within GDB to print information about HIToolbox objects in your process, including events, menus, windows, dialogs, and controls.

  • There are routines to flash regions so that can visualize them on screen.

  • This are a variety of facilities to trace events as they flow through the toolbox.

HIToolbox Object Printing Routines

The following listings show the various HIToolbox object printing routines.

Listing 28: HIToolbox event printing

(gdb) call (int)GDBPrintEventQueue()

Printing event queue 0x7632536c...
RunLoop: 0x40c560
Count: 4 Header: 0x1805010 Head: 0x49faf0 Tail: 0x489d10

EventRef Event Kind           Time       P Cnt Desc
-------- -------------------- ---------- - --- --------------------
  49FAF0 kEventMouseDown       219335.28 H 001 x=879, y=61, button 1
  489530 kEventWindowActivate  219335.46 H 002 0x4350A0 "Untitled 1"
  43A4E0 kEventAppActiveWindo 218971.143 S 002
  489D10 kEventWindowUpdate   219335.473 L 002 0x4A3C10 "Untitled 1 Properties"
$2 = 0
(gdb) echo 0x489D10 is the kEventWindowUpdate event from last command\n
0x489D10 is the kEventWindowUpdate event from last command
(gdb) call (void) _DebugPrintEvent(0x489D10)
Displaying event 489D10...
   Class           wind
   Kind            1
   When                219335
   Priority        Low
   RetainCount     2
   Queued          Yes
   Info            kEventWindowUpdate, 0x4A3C10 "Untitled 1 Properties"
   Parameters
        param: ----
           type: wind
           size: 4
           data: 004A3C10
                  J<

Listing 29: HIToolbox menu printing

(gdb) call (void) DebugPrintMenuList()
Index  MenuRef     ID   Title
-----  ----------  ------  -----
    1  0x0041F330  -21629  <Apple>
    2  0x0042EC00     128  QuickTime Player
    3  0x0043C4B0     129  File
    4  0x00445B70     130  Edit
[Ö]
<hierarchical menus>
           0x0042CF90     140  Open Recent
(gdb) echo 0x0042EC00 is the QuickTime Player menu\n
0x0042EC00 is the QuickTime Player menu
(gdb) set $menu=0x0042EC00
(gdb) call (void) DebugPrintMenu($menu)
MenuRef:          0x0042EC00
    Title               : QuickTime Player
    ID                  : 128
    Width               : 0
    Height              : 0
    Enabled             : true
    Attributes          : CondenseSeparators, ReceivedInit
    Modal level         : 0
    Refcount            : 3
    Element             : 0x004435B0
    Item Count          : 12
    Item Icon  Cmd Key   Mark   CmdID E V Text
    ---- ---- -------- -------- ----- - - ----
    0001 0000 0x00 ' ' 0x00 ' '       Y Y About QuickTime Player
    0002 0000 0x00 ' ' 0x00 ' '       N Y -
    0003 0000 0x00 ' ' 0x00 ' '  pref Y Y Preferences
[Ö]
HIObject
    Ref count           : 3
    Event Target        : 0x42f040
    Event Handler       : 0x436f10
(gdb) call (void) DebugPrintMenuItem($menu, 1)
Menu: 0x0042EC00 Item: 1 Info:
 Text:                  About QuickTime Player
 Mark:                  <none>
 Cmd Key:               <none>
 Icon:                  <none>
 Style Normal
 Command ID:          0 (0x00000000)
 Modifiers:            0x00
[Ö]

Listing 30: HIToolbox window and dialog printing

(gdb) call (void) DebugPrintWindowList()

Window      Class    WID  Vis Hil Level Title                 Group
----------  -------- ---- --- --- ----- --------------------- -----------Ö
0x004350A0  Document 4ED4  Y   Y      0 Untitled 1            0x76E47A89 Ö
0x004A3C10  Document 4EED  Y   N      0 Untitled 1 Properties 0x76E47A89 Ö
(gdb) echo 0x004350A0 is the "Untitled 1" window\n
0x004350A0 is the "Untitled 1" window
(gdb) set $window=0x004350A0
(gdb) echo 0x004A3C10 is the "Untitled 1 Properties" dialog\n
0x004A3C10 is the "Untitled 1 Properties" dialog
(gdb) set $dialogWindow=0x004A3C10
(gdb) call (void) DebugPrintWindow($window)
Window 0x004350A0
    Title               : Untitled 1
    Class               : Document
    Group               : 0x76E47A89 "com.apple.HIToolbox.windowgroups.document"
    Scope               : all
    Attributes          : Collapse Box, In WindowMenu
    Visible             : Yes
    Collapsed           : No
    Latent visibility   : <none>
    Highlighted         : Yes
    Structure region    : 1FE80C #0, #0, #106, #352 (#352w x #106h) [non-rect]
[Ö]
(gdb) call (void) DebugPrintAllWindowGroups()
Window group tree
-------------------------------------------------------------------------Ö
  1  level    0  group 0x76E0BFE9 "com.apple.hitoolbox.windowgroups.root"
  2  level    0    group 0x76E47A89 "com.apple.HIToolbox.windowgroups.docÖ
(gdb) echo 0x76E47A89 is the second window group\n
0x76E47A89 is the second window group
(gdb) call (void) DebugPrintWindowGroup(0x76E47A89)
WindowGroup 0x76E47A89 "com.apple.HIToolbox.windowgroups.document"
 Attributes:           <none>
 Refcount:             1
 Previous group:       <none>
 Next group:           <none>
 Parent group:         0x76E0BFE9 "com.apple.hitoolbox.windowgroups.root"
[Ö]
(gdb) set $dialog = (void *) GetDialogFromWindow($dialogWindow)
(gdb) call (void) GDBShowDialogInfo($dialog)
Dialog:                 0x76ED59A1
 Window:                0x004A3C10 "Untitled 1 Properties"
 TextHandle:            0x0059EC7C
 Default Item:          1
 Cancel Item:           0
 Keyboard Focus Item:   0
 RefCon:                0x06054AB5 (101010101)

Listing 31: HIToolbox control printing

(gdb) call (void) GDBShowControlHierarchy($window)
Dumping info for window 0x4A3C10
Window found. Dumping views...
Root 0x4ba260 , ID ''/0, (-32768,-32768,32767,32767), Embedder, Vis, Act,Ö
    Control 0x4c24d0 <appl/sbar> ( "" ), ID ''/0, (172,301,226,317), Vis,Ö
    Control 0x4c6080 <appl/sbar> ( "" ), ID ''/0, (75,301,142,317), Vis, Ö
    Control 0x4c49c0 <appl/push> ( "Delete" ), ID ''/0, (241,220,261,290)Ö
    Control 0x4c4790 <appl/push> ( "Edit?" ), ID ''/0, (241,135,261,205),Ö
    Control 0x4c17c0 <appl/push> ( "Add?" ), ID ''/0, (241,50,261,120), VÖ
    Control 0x4be1d0 <appl/popb> ( "" ), ID ''/0, (12,176,28,316), Vis, AÖ
    Control 0x4ba1f0 <appl/popb> ( "" ), ID ''/0, (12,24,28,164), Vis, AcÖ
(gdb) echo 0x4c24d0 is first scrollbar control\n
echo 0x4c24d0 is first scroll bar control
(gdb) call (void) GDBShowControlInfo(0x4c24d0)
HIScrollBar
    Size                : Auto
    Live Tracking       : No
Control 0x004C24D0 ""
    Control Kind        : 'appl', 'sbar'
    Control ID          : '', 0
    Window              : 0x004A3C10 "Untitled 1 Properties"
    Parent              : 0x004BA260
    Minimum             : 0 (0x00000000)
    Maximum             : 0 (0x00000000)
    Value               : 0 (0x00000000)
[Ö]
HIObject
    Ref count           : 1
    Event Target        : 0x4c39a0
    Event Handler       : 0x4c3a10

Back to Top 

HIToolbox Region Flashing

The routines shown in Listing 32 can be used to flash regions so that you can visualize them on screen; unfortunately you can't see the results in this document, so you'll have to try this yourself.

Listing 32: HIToolbox region flashing routines

(gdb) call (void) DebugFlashWindowVisRgn(0x004351E0)
(gdb) call (void) DebugFlashWindowUpdateRgn(0x004351E0)

Back to Top 

HIToolbox Event Debugging

With the advent of Carbon Events, it's often hard to understand the flow of events through the toolbox. HIToolbox offers two debugging facilities that can help here.

EventDebug Environment Variable

By setting the EventDebug environment variable to 1, you cause HIToolbox to log all events as they flow through the system. Listing 33 shows an example of this.

Listing 33: EventDebug output

$ EventDebug=1 /Applications/QuickTime\ Player.app/Contents/MacOS/\
QuickTime\ Player
Event Posted: Queue: 0x763059ae, Event: kEventAppleEvent, 221132.233, S Ö
SendEventToEventTarget entered
    Sending Event to 0x4128E0: hiob 2
        Called handler 0x927F3200. Event was handled
        Leaving target 0x4128E0 with result 0
SendEventToEventTarget entered
    Sending Event to 0x41E6F0: hiob 2
        SendEventToEventTarget entered
            Sending Event to 0x41EC30: hiob 2
                SendEventToEventTarget entered
                    Sending Event to 0x41EC30: hiob 2
                        Called handler 0x927F3200. Event was handled
                        Leaving target 0x41EC30 with result 0
                Called handler 0x927FBB50. Event was handled
                Leaving target 0x41EC30 with result 0
        Called handler 0x927F3200. Event was handled
        Leaving target 0x41E6F0 with result 0
[Ö]

Back to Top 

Event Tracing

The EventDebug environment variable produces a lot of output, which can have some negative effects. Specifically, it slows your program down considerably and it's sometimes hard to find the information you're looking for amongst all the output.

One solution to this problem is to enable event-by-event tracing. You can do this by calling the TraceEventByName routine from within GDB. Listing 34 shows an example of this, enabling tracing just for the kEventRawKeyDown event.

Listing 34: Event tracing

(gdb) call (void) TraceEventByName("kEventRawKeyDown")
(gdb) c
Continuing.
Event Posted: Queue: 0x76309338, Event: kEventRawKeyDown, 221443.183, S
SendEventToEventTarget entered
    Sending Event to 0x415750: kEventRawKeyDown
        SendEventToEventTarget entered
            Sending Event to 0x413050: kEventRawKeyDown
                Called handler 0x928CD05C. Event was NOT handled
                Leaving target 0x413050 with result -9874
        SendEventToEventTarget entered
            Sending Event to 0x42DE30: kEventRawKeyDown
                Leaving target 0x42DE30 with result -9874
            Sending Event to 0x4351F0: kEventRawKeyDown
                Leaving target 0x4351F0 with result -9874
            Sending Event to 0x4126F0: kEventRawKeyDown
                Called handler 0x929597E0. Event was NOT handled
                Called handler 0x927F4F40. Event was NOT handled
                Leaving target 0x4126F0 with result -9874
        Leaving target 0x415750 with result -9874
Event Removed: Queue: 0x76309338, Event: kEventRawKeyDown, 221443.183, S
Event Pulled (C): kEventRawKeyDown, 221443.183, S

Back to Top 

HIToolbox Event Statistics

There are two environment variables that cause HIToolbox to print event statistics. If you set EventRate to 1, HIToolbox will, every second, print a summary of the events handled that second. If you set HLTBRecordEventStats, HIToolbox will print a bunch of statistics about event handling when your application quits; this feature requires the debug library.

Back to Top 

Other HIToolbox Debugging Facilities

If you set the NSQuitAfterLaunch environment variable to 1, your application will quit as soon as it enters its event loop. This is useful if you want to measure application launch time, or look for leaks. This environment variable is also supported by AppKit.

If you set the HLTBPrintKeyMatchingStatus environment variable to 1, HIToolbox will print detailed information about menu item matching. This feature requires the debug library.

If you set the TSMEventTracing environment variable to 1, HIToolbox will print detailed information about Text Services Manager (TSM) event processing.

Back to Top 

Cocoa

All Cocoa objects (everything derived from NSObject) support a description method that returns an NSString describing the object. The most convenient way to access this description is via GDB's print-object (or po for short) command, as illustrated by Listing 35.

Listing 35: Using GDB's po command

$ gdb /Applications/TextEdit.app
GNU gdb 5.3-20030128 (Apple version gdb-330.1) [Ö]
(gdb) fb *'-[NSDictionary hash]'
No symbol table is loaded.  Use the "file" command.
Breakpoint 1 at 0x0
(gdb) r
[Ö]
Breakpoint 1, 0x90a233d8 in -[NSDictionary hash] ()
(gdb) po $r3
<NSAttributeDictionary 0x159330>{
  NSParagraphStyle = Alignment 4, LineSpacing 0, \
ParagraphSpacing 0, ParagraphSpacingBefore 0, HeadIndent 0, \
TailIndent 0, FirstLineHeadIndent 0, LineHeight 0/0, \
LineHeightMultiple 0, LineBreakMode 2, Tabs (28L, 56L, 84L, \
112L, 140L, 168L, 196L, 224L, 252L, 280L, 308L, 336L), \
DefaultTabInterval 0;
  NSColor = NSCalibratedWhiteColorSpace 1 1;
  NSFont = "CGS LucidaGrande 13.00 pt. P [] (0x00158af0) \
fobj=0x00156f50, spc=4.11";
  _NSOriginalFontAttributeName = "CGS LucidaGrande 13.00 pt. \
P [] (0x00158af0) fobj=0x00156f50, spc=4.11";
}

Note: print-object actually calls the debugDescription method of the specified object. NSObject implements this method by calling through to the description method. Thus, by default, an object's debug description is the same as its description. However, you can override debugDescription if you want to decouple these; many Cocoa objects do this.

When debugging Cocoa code at the assembly level, keep in mind the following features of the Objective-C runtime.

  • The Objective-C compiler adds two implicit parameters to each method. The first is a pointer to the object being messaged (self). On PowerPC this is in register r3.

  • The second implicit parameter is the method selector. In Objective-C this is of type SEL; in GDB you can print this as a C string. On PowerPC this parameter is in register r4.

  • The Objective-C runtime dispatches methods via a C function called objc_msgSend.

  • The first word of any Objective-C object (the isa field) is a pointer to the object's class.

Listing 36 shows an example of how to use this information from GDB.

Listing 36: Objective-C runtime 'secrets'

$ gdb /Applications/TextEdit.app
GNU gdb 5.3-20030128 (Apple version gdb-330.1) [Ö]
(gdb) r
Starting program: /Applications/TextEdit.app/Contents/MacOS/TextEdit
[Ö]
^C
Program received signal SIGINT, Interrupt.
0x900074c8 in mach_msg_trap ()
(gdb) echo Set a breakpoint on the Objective-C method dispatcher.\n
Set a breakpoint on the Objective-C method dispatcher.
(gdb) b objc_msgSend
Breakpoint 1 at 0x908311f4
(gdb) echo Continue execution...\n
Continue execution...
(gdb) c
Continuing.

Breakpoint 1, 0x908311f4 in objc_msgSend ()
(gdb) echo Hit the breakpoint; dump the first 4 words of the object.\n
Hit the breakpoint; dump the first 4 words of the object.
(gdb) x/4x $r3
0x10cc10:       0xa0a04e18      0x00000001      0x00000000      0x00000000
(gdb) echo Print the selector.\n
Print the selector.
(gdb) x/s $r4
0x9083ed94 <_errDoesntRecognize+884>:    "init"
(gdb) echo Want to 'po' object; must disable the breakpoint first.\n
Want to 'po' object; must disable the breakpoint first.
(gdb) dis 1
(gdb) po $r3
<NSAutoreleasePool: 0x10cc10>
(gdb) echo Print the 'isa' pointer.\n
Print the 'isa' pointer.
(gdb) po 0xa0a04e18
NSAutoreleasePool

Foundation

Foundation has numerous debugging facilities that are enabled by environment variables. Table 5 highlights some of the more interesting ones; these are all further documented in NSDebug.h.

Table 5: Environment variables from 'NSDebug.h'

NameDefaultAction
NSZombieEnabledNOIf set to YES, deallocated objects are 'zombified'; this allows you to quickly debug problems where you send a message to an object that has already been freed; see below for details
NSDeallocateZombiesNOIf set to YES, the memory for 'zombified' objects is actually freed
NSHangOnUncaughtExceptionNOIf set to YES, the process will hang, rather than quit, when an uncaught exception is raised
NSEnableAutoreleasePoolYESIf set to NO, autorelease pools do not release objects in the pool when the pool is released
NSAutoreleaseFreedObjectCheckEnabledNOIf set to YES, autorelease pools will print a message if they try to release an object that has already been freed
NSAutoreleaseHighWaterMark0If set to X, autorelease pools will print a message if more than X objects accumulate in the pool
NSAutoreleaseHighWaterResolution0If set to Y, a message is logged for every Y objects that accumulate in the pool beyond the high-water mark (X)

IMPORTANT: To enable or disable a Foundation debugging facility, you should set the value of the environment variable to "YES" or "NO", not 1 or 0 as is the case with other system components.

One of the most common forms of bugs when programming with Cocoa is caused by over-releasing an object. This typically causes your application to crash, but the crash occurs when the last reference count is released, which is usually quite removed from the original bug. NSZombieEnabled is your best bet for debugging this sort of problems because any attempt to interact with a freed object will raise an exception. Listing 37 shows an example of the message you'll see in this case.

Listing 37: The effect of NSZombie

$ NSZombieEnabled=YES DragNDropOutlineView
2004-04-30 14:56:28.238 DragNDropOutlineView[803] *** *** Selector \
'_propagateDirtyRectsToOpaqueAncestors' sent to dealloced instance \
0x530540 of class AnimatingOutlineView.

You can use GDB to set a breakpoint on -[_NSZombie methodSignatureForSelector:] to further debug this sort of problem.

You can enable logging for Foundation's scripting support using the NSScriptingDebugLogLevel preference. Listing 38 shows an example of this; the log shown is the result of running the trivial AppleScript: version of application "TextEdit".

Listing 38: Enabling NSScriptingDebugLogLevel

$ defaults write com.apple.TextEdit NSScriptingDebugLogLevel YES
$ /Applications/TextEdit.app/Contents/MacOS/TeÖ
[Ö]
2004-09-07 15:57:21.449 TextEdit[4417] Command: NSCoreSuite.Get
        Direct Parameter: <NSPropertySpecifier: version>
        Receivers: <NSPropertySpecifier: version>
        Arguments: {}
2004-09-07 15:57:21.449 TextEdit[4417] Property Value: 1.3
2004-09-07 15:57:21.449 TextEdit[4417] Result: <NSAppleEventDescriptor:  Ö
[Ö]

If you set the NSPrintDynamicClassLoads environment variable to "YES", Foundation will log a message whenever it loads a class or category dynamically (that is, from a bundle).

If you set the NSExceptionLoggingEnabled environment variable to "YES", Foundation will log all exception activity (NSException) to stderr.

If you set the NSUnbufferedIO environment variable to "YES", Foundation will use unbuffered I/O for stdout (stderr is unbuffered by default).

If you set the NSDOLoggingEnabled environment variable to "YES", Foundation will enable logging for Distributed Objects (NSConnection, NSInvocation, NSDistantObject, and NSConcretePortCoder).

Back to Top 

AppKit

If you set the NSQuitAfterLaunch environment variable to 1, your application will quit as soon as it enters its event loop. This is useful if you want to measure application launch time or look for leaks. This environment variable is also supported by Carbon.

AppKit Events

If you set the NSTraceEvents preference to YES, AppKit will log information about all events it processes. Listing 39 shows an example of this.

Listing 39: Using NSTraceEvents

$ defaults write com.apple.TextEdit NSTraceEvents YES
$ /Applications/TextEdit.app/Contents/MacOS/TextEdit
2004-09-07 16:21:23.334 TextEdit[4520] timeout = 62997727116.666718 secoÖ
2004-09-07 16:21:23.341 TextEdit[4520] got apple event of class 61657674Ö
2004-09-07 16:21:23.454 TextEdit[4520] still in loop, timeout = 62997727Ö
2004-09-07 16:21:23.455 TextEdit[4520] timeout = 62997727116.546562 secoÖ
2004-09-07 16:21:27.793 TextEdit[4520] Received event: Kitdefined at: 0.Ö
2004-09-07 16:21:27.804 TextEdit[4520]     In Application: NSEvent: typeÖ
2004-09-07 16:21:27.804 TextEdit[4520] timeout = 62997727112.196404 secoÖ
2004-09-07 16:21:27.805 TextEdit[4520] Received event: LMouseDown at: 37Ö
2004-09-07 16:21:27.805 TextEdit[4520]     In Application: NSEvent: typeÖ
2004-09-07 16:21:27.805 TextEdit[4520]     In Window: NSEvent: type=LMouÖ
2004-09-07 16:21:27.809 TextEdit[4520]     In Application: NSEvent: typeÖ
[Ö]

Back to Top 

AppKit Views

If you set the NSShowAllViews preference to YES, AppKit will draw outlines around each of the views in a window. Figure 4 shows how a standard TextEdit window looks with NSShowAllViews enabled.

Figure 4: TextEdit with NSShowAllViews enabled

Figure 4, TextEdit with NSShowAllViews enabled

If you set the NSShowAllDrawing preference to YES, AppKit will flash every rectangle that it draws, much like Quartz Debug. Figure 5 shown an example of what to expect.

Figure 5: NSShowAllDrawing in action

Figure 5, NSShowAllDrawing in action

You can control the duration of the flash by setting NSShowAllDrawing to a number, which is interpreted as the number of milliseconds to flash; the default is 100 ms. You can control the color of the flash by setting NSShowAllDrawingColor to a string that holds three floating point numbers, separated by spaces, representing the red, green, and blue color components. Each number should be a value from 0.0 to 1.0 representing the intensity of that component. For example, the string "0.0 1.0 1.0" would yield pure cyan. Alternatively, if you set NSShowAllDrawingColor to "CYCLE", AppKit will cycle through pure red, pure green, and pure blue.

Back to Top 

Other AppKit Debugging Facilities

The NSDragManagerLogLevel preference is a number that controls how much logging AppKit does during drag and drop operations. Large values give you more logging. Currently the value of 6 is the maximum effective value. Listing 40 shows an example of how to set this and the kind of output you get when you drag a simple text selection from TextEdit.

Listing 40: Using NSDragManagerLogLevel

$ defaults write com.apple.TextEdit NSDragManagerLogLevel 6
$ /Applications/TextEdit.app/Contents/MacOS/TextEdit
2004-09-07 16:26:42.031 TextEdit[4523] mouseDown location: {29, 389}, baÖ
2004-09-07 16:26:42.033 TextEdit[4523] offset of image lower left relatiÖ
2004-09-07 16:26:42.033 TextEdit[4523] type NeXT Rich Text Format v1.0 pÖ
2004-09-07 16:26:42.034 TextEdit[4523] type NSStringPboardType: data <CFÖ
2004-09-07 16:26:42.034 TextEdit[4523] type NeXT plain ascii pasteboard Ö
2004-09-07 16:26:42.036 TextEdit[4523] type CorePasteboardFlavorType 0x7Ö
2004-09-07 16:26:42.036 TextEdit[4523] type CorePasteboardFlavorType 0x7Ö
2004-09-07 16:26:42.049 TextEdit[4523] type CorePasteboardFlavorType 0x5Ö
2004-09-07 16:26:42.050 TextEdit[4523] type CorePasteboardFlavorType 0x7Ö
[Ö]

The NSAccessibilityDebugLogLevel preference is a number that controls how much logging AppKit does during accessibility operations. Large values give you more logging. Currently the value of 3 is the maximum effective value. Listing 41 shows an example of how to set this and the kind of output you get when you use UIElementInspector (see Sample Code Project 'UIElementInspector') to look at TextEdit.

Listing 41: Using NSAccessibilityDebugLogLevel

$ defaults write com.apple.TextEdit NSAccessibilityDebugLogLevel 3
$ /Applications/TextEdit.app/Contents/MacOS/TextEdit
2004-09-07 16:36:34.990 TextEdit[4526] creating id<=element table
2004-09-07 16:36:34.990 TextEdit[4526] creating id=>element
2004-09-07 16:36:35.001 TextEdit[4526] Element<=>UniqueId Tables
--- id<=element --- size 1
42 <- (0x1576e0): <NSTextView: 0x1576e0>
    Frame = {{0.00, 0.00}, {460.00, 395.00}}, Bounds = {{0.00, 0.00}, Ö
    Horizontally resizable: NO, Vertically resizable: YES
    MinSize = {460.00, 395.00}, MaxSize = {340282346638528859811704183Ö
2004-09-07 16:36:35.003 TextEdit[4526] Element<=>UniqueId Tables
[Ö]

Back to Top 

Document Revision History

DateNotes
2004-12-02First Version

Posted: 2004-12-02